11-19 20:30:25 D/ModuleListener: ModuleListener.testStarted(com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testDistanceToTheMoon) on SKBFXYZO0C1V
11-19 20:30:25 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:25 D/DeviceHostUtils: apiLevel: 31
11-19 20:30:25 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:25 D/DeviceHostUtils: apiLevel: 31
11-19 20:30:25 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:30:25 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
11-19 20:30:25 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
11-19 20:30:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:26 D/RunUtil: Running command null without timeout.
11-19 20:30:26 D/AppRunnerUtils: Checking service: com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
11-19 20:30:26 D/AppRunnerUtils: Running the following command: dumpsys activity service com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService
11-19 20:30:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, dumpsys, activity, service, com.google.android.katniss/.search.serviceapi.KatnissVoiceInteractionService] with timeout: 2m 0s
11-19 20:30:26 I/AppRunnerUtils: Service PID = 14230
11-19 20:30:26 I/AssistantTestUtils: Waiting for assistant to be ready...
11-19 20:30:26 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
11-19 20:30:26 D/AssistantTestUtils: Launching Assistant intent
11-19 20:30:26 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
11-19 20:30:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
11-19 20:30:26 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
11-19 20:30:26 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:30:26 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:30:26 I/DeviceStateMonitor: Waiting 359907 ms for device SKBFXYZO0C1V package manager
11-19 20:30:27 I/NativeDeviceStateMonitor: Waiting 359750 ms for device SKBFXYZO0C1V external store
11-19 20:30:30 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:30:30 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
11-19 20:30:30 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
11-19 20:30:30 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
11-19 20:30:30 D/AssistantTestUtils: Assistant successfully launched: true
11-19 20:30:30 D/RunUtil: Running command [logcat -d | grep -E 'AssistantWrapper(Impl)?: Assistant is now running.'] without timeout.
11-19 20:30:30 I/AssistantTestUtils: Assistant ready: true
11-19 20:30:30 D/RunUtil: Running command [launch Assistant intent, then check if Assistant is in foreground] without timeout.
11-19 20:30:30 D/AssistantTestUtils: Launching Assistant intent
11-19 20:30:30 D/AppRunnerUtils: Running the following command: am start --es query Weather -p com.google.android.katniss -c android.intent.category.DEFAULT -a android.intent.action.ASSIST
11-19 20:30:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, start, --es, query, Weather, -p, com.google.android.katniss, -c, android.intent.category.DEFAULT, -a, android.intent.action.ASSIST] with timeout: 2m 0s
11-19 20:30:30 D/RunUtil: Running command [check if Assistant is in foreground] without timeout.
11-19 20:30:30 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:30:30 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:30:31 I/DeviceStateMonitor: Waiting 359933 ms for device SKBFXYZO0C1V package manager
11-19 20:30:31 I/NativeDeviceStateMonitor: Waiting 359786 ms for device SKBFXYZO0C1V external store
11-19 20:30:33 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:30:33 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.google.android.apps.tvsearch.results.activity.SearchResultActivity.
11-19 20:30:33 D/AssistantTestUtils: Supplier "check if Assistant is in foreground" returned: true
11-19 20:30:33 D/AssistantTestUtils: Supplier "launch Assistant intent, then check if Assistant is in foreground" returned: true
11-19 20:30:33 D/AssistantTestUtils: Assistant successfully launched: true
11-19 20:30:33 D/RunUtil: Running command [check if metrics file pattern is present] without timeout.
11-19 20:30:33 I/AssistantTestUtils: Checking if file pattern is present: /storage/emulated/0/Download/katniss-primes*
11-19 20:30:33 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
11-19 20:30:34 D/AssistantTestUtils: Supplier "check if metrics file pattern is present" returned: true
11-19 20:30:34 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, ls, -t, -d, /storage/emulated/0/Download/katniss-primes*] with timeout: 2m 0s
11-19 20:30:34 D/AssistantTestUtils: Session-based metrics File: /storage/emulated/0/Download/katniss-primes-2024-11-19T03_30_32.742.txt
11-19 20:30:34 D/NativeDevice: Using 'ls' to check doesFileExist(/storage/emulated/0/Download/katniss-primes-2024-11-19T03_30_32.742.txt)
11-19 20:30:34 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:34 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_5530394911789978504.txt'] without timeout.
11-19 20:30:34 D/TvtsBaseAssistantTest: Metrics location: /storage/emulated/0/Download/katniss-primes-2024-11-19T03_30_32.742.txt
11-19 20:30:34 D/TvtsBaseAssistantTest: Option enabling successful!
11-19 20:30:34 I/TvtsBaseAssistantTest: Test: MoonTest
11-19 20:30:34 I/MeasurementPrinter: search_to_query_latency	Measurement Status	query_to_result_latency	Measurement Status	query_to_result_no_server_latency	Measurement Status
11-19 20:30:34 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:30:34 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:30:34 I/DeviceStateMonitor: Waiting 359938 ms for device SKBFXYZO0C1V package manager
11-19 20:30:34 I/NativeDeviceStateMonitor: Waiting 359871 ms for device SKBFXYZO0C1V external store
11-19 20:30:36 D/RunUtil: Running command null without timeout.
11-19 20:30:36 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:36 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:36 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:30:36 D/RunUtil: Running command null without timeout.
11-19 20:30:36 D/AppRunnerUtils: foregroundActivitySet(): [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:30:36 I/KeyCodeUtils: Sending keyevent KEYCODE_HOME - intValue: 3
11-19 20:30:36 D/AppRunnerUtils: [com.google.android.katniss/com.google.android.apps.tvsearch.results.activity.SearchResultActivity]
11-19 20:30:36 D/RunUtil: operation failed, waiting for 500 ms
11-19 20:30:37 D/RunUtil: Running command null without timeout.
11-19 20:30:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:38 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:30:38 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:30:38 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:38 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_9414023645009373612.txt'] without timeout.
11-19 20:30:38 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:30:38 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:30:38 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:30:38 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:30:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:49 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:30:49 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 1089.000000
11-19 20:30:49 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 1088.000000
11-19 20:30:49 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 237.000000
11-19 20:30:49 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 1089.000000
11-19 20:30:49 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 30.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:30:49 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:30:49 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 290.000000
11-19 20:30:49 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 3048.000000
11-19 20:30:49 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:30:49 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 92.000000
11-19 20:30:49 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 4000.000000
11-19 20:30:49 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2901.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:30:49 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 64.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 78.000000
11-19 20:30:49 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 121.000000
11-19 20:30:49 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:30:49 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 28.000000
11-19 20:30:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:49 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:30:49 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 1089.000000
11-19 20:30:49 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:30:49 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 1088.000000
11-19 20:30:49 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 237.000000
11-19 20:30:49 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 1089.000000
11-19 20:30:49 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 30.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:30:49 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:30:49 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 290.000000
11-19 20:30:49 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 3048.000000
11-19 20:30:49 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:30:49 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 92.000000
11-19 20:30:49 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 4000.000000
11-19 20:30:49 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2901.000000
11-19 20:30:49 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:30:49 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 64.000000
11-19 20:30:49 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 78.000000
11-19 20:30:49 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 121.000000
11-19 20:30:49 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 28.000000
11-19 20:30:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:50 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:30:50 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 1089.000000
11-19 20:30:50 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:30:50 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 1088.000000
11-19 20:30:50 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 237.000000
11-19 20:30:50 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 1089.000000
11-19 20:30:50 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 30.000000
11-19 20:30:50 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 4.000000
11-19 20:30:50 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:30:50 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:30:50 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 290.000000
11-19 20:30:50 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 3048.000000
11-19 20:30:50 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:30:50 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 92.000000
11-19 20:30:50 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 4000.000000
11-19 20:30:50 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2901.000000
11-19 20:30:50 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:30:50 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:30:50 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 64.000000
11-19 20:30:50 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 78.000000
11-19 20:30:50 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 121.000000
11-19 20:30:50 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 28.000000
11-19 20:30:50 I/MeasurementPrinter:                   121.0	                OK	                 3990.0	                OK	                           1089.0	                OK
11-19 20:30:50 D/RunUtil: Running command null without timeout.
11-19 20:30:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:50 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:30:50 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:50 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:51 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:30:51 D/RunUtil: Running command null without timeout.
11-19 20:30:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:51 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:30:51 D/RunUtil: Running command null without timeout.
11-19 20:30:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:51 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:30:51 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:30:51 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:30:51 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:30:53 D/RunUtil: Running command null without timeout.
11-19 20:30:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:30:53 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:30:53 D/RunUtil: Running command null without timeout.
11-19 20:30:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:30:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:30:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:30:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:30:54 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_15520149801593735746.txt'] without timeout.
11-19 20:30:55 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:30:55 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:30:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:30:55 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:31:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:05 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:31:05 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 866.000000
11-19 20:31:05 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 865.000000
11-19 20:31:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 222.000000
11-19 20:31:05 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 867.000000
11-19 20:31:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 23.000000
11-19 20:31:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:31:05 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 170.000000
11-19 20:31:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2892.000000
11-19 20:31:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:31:05 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3634.000000
11-19 20:31:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2763.000000
11-19 20:31:05 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 26.000000
11-19 20:31:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:31:05 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:31:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:31:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:05 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:31:05 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 866.000000
11-19 20:31:05 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:05 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 865.000000
11-19 20:31:05 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 222.000000
11-19 20:31:05 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 867.000000
11-19 20:31:05 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 23.000000
11-19 20:31:05 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:31:05 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 170.000000
11-19 20:31:05 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2892.000000
11-19 20:31:05 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:31:05 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3634.000000
11-19 20:31:05 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2763.000000
11-19 20:31:05 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:31:05 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 26.000000
11-19 20:31:05 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:31:05 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:31:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:06 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:31:06 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 866.000000
11-19 20:31:06 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:06 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 865.000000
11-19 20:31:06 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 222.000000
11-19 20:31:06 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 867.000000
11-19 20:31:06 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 2, sum: 23.000000
11-19 20:31:06 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:31:06 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 170.000000
11-19 20:31:06 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2892.000000
11-19 20:31:06 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:31:06 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3634.000000
11-19 20:31:06 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2763.000000
11-19 20:31:06 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 26.000000
11-19 20:31:06 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:31:06 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:31:06 I/MeasurementPrinter:                    98.0	                OK	                 3629.0	                OK	                            866.0	                OK
11-19 20:31:06 D/RunUtil: Running command null without timeout.
11-19 20:31:06 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:06 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:06 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:06 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:07 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:07 D/RunUtil: Running command null without timeout.
11-19 20:31:07 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:07 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:07 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:07 D/RunUtil: Running command null without timeout.
11-19 20:31:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:07 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:31:07 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:31:07 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:31:07 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:31:09 D/RunUtil: Running command null without timeout.
11-19 20:31:09 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:09 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:09 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:09 D/RunUtil: Running command null without timeout.
11-19 20:31:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:10 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:31:10 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:10 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_6035474500894645948.txt'] without timeout.
11-19 20:31:10 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:31:10 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:31:10 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:31:11 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:31:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:21 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:31:21 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 811.000000
11-19 20:31:21 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 810.000000
11-19 20:31:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 225.000000
11-19 20:31:21 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 811.000000
11-19 20:31:21 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 29.000000
11-19 20:31:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 92.000000
11-19 20:31:21 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 107.000000
11-19 20:31:21 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2676.000000
11-19 20:31:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:31:21 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3432.000000
11-19 20:31:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2619.000000
11-19 20:31:21 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 51.000000
11-19 20:31:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 87.000000
11-19 20:31:21 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:31:21 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 26.000000
11-19 20:31:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:21 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:31:21 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 811.000000
11-19 20:31:21 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:21 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 810.000000
11-19 20:31:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 225.000000
11-19 20:31:21 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 811.000000
11-19 20:31:21 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 29.000000
11-19 20:31:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 92.000000
11-19 20:31:21 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 107.000000
11-19 20:31:21 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2676.000000
11-19 20:31:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:31:21 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3432.000000
11-19 20:31:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2619.000000
11-19 20:31:21 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:31:21 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 51.000000
11-19 20:31:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 87.000000
11-19 20:31:21 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 26.000000
11-19 20:31:21 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:21 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:31:21 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 811.000000
11-19 20:31:21 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:21 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 810.000000
11-19 20:31:21 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 225.000000
11-19 20:31:21 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 811.000000
11-19 20:31:21 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 29.000000
11-19 20:31:21 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 92.000000
11-19 20:31:21 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 107.000000
11-19 20:31:21 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2676.000000
11-19 20:31:21 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:31:21 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3432.000000
11-19 20:31:21 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2619.000000
11-19 20:31:21 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 51.000000
11-19 20:31:21 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 87.000000
11-19 20:31:21 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 26.000000
11-19 20:31:21 I/MeasurementPrinter:                    87.0	                OK	                 3430.0	                OK	                            811.0	                OK
11-19 20:31:21 D/RunUtil: Running command null without timeout.
11-19 20:31:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:22 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:22 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:22 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:23 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:23 D/RunUtil: Running command null without timeout.
11-19 20:31:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:23 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:23 D/RunUtil: Running command null without timeout.
11-19 20:31:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:23 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:31:23 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:31:23 I/DeviceStateMonitor: Waiting 359962 ms for device SKBFXYZO0C1V package manager
11-19 20:31:23 I/NativeDeviceStateMonitor: Waiting 359900 ms for device SKBFXYZO0C1V external store
11-19 20:31:25 D/RunUtil: Running command null without timeout.
11-19 20:31:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:25 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:25 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:25 D/RunUtil: Running command null without timeout.
11-19 20:31:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:26 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:31:26 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:26 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_13866511142525823123.txt'] without timeout.
11-19 20:31:26 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:31:26 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:31:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:31:26 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:31:37 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:37 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:31:37 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 859.000000
11-19 20:31:37 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 858.000000
11-19 20:31:37 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 248.000000
11-19 20:31:37 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 858.000000
11-19 20:31:37 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 36.000000
11-19 20:31:37 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 109.000000
11-19 20:31:37 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 140.000000
11-19 20:31:37 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2864.000000
11-19 20:31:37 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:31:37 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3640.000000
11-19 20:31:37 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2780.000000
11-19 20:31:37 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 63.000000
11-19 20:31:37 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 78.000000
11-19 20:31:37 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:31:37 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
11-19 20:31:37 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:37 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:31:37 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 859.000000
11-19 20:31:37 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:37 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 858.000000
11-19 20:31:37 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 248.000000
11-19 20:31:37 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 858.000000
11-19 20:31:37 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 36.000000
11-19 20:31:37 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 109.000000
11-19 20:31:37 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 140.000000
11-19 20:31:37 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2864.000000
11-19 20:31:37 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:31:37 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3640.000000
11-19 20:31:37 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2780.000000
11-19 20:31:37 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:31:37 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 63.000000
11-19 20:31:37 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 78.000000
11-19 20:31:37 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
11-19 20:31:37 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:37 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:31:37 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 859.000000
11-19 20:31:37 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:37 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 858.000000
11-19 20:31:37 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 248.000000
11-19 20:31:37 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 858.000000
11-19 20:31:37 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 36.000000
11-19 20:31:37 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 109.000000
11-19 20:31:37 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 140.000000
11-19 20:31:37 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2864.000000
11-19 20:31:37 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:31:37 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3640.000000
11-19 20:31:37 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2780.000000
11-19 20:31:37 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 63.000000
11-19 20:31:37 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 78.000000
11-19 20:31:37 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
11-19 20:31:37 I/MeasurementPrinter:                    78.0	                OK	                 3639.0	                OK	                            859.0	                OK
11-19 20:31:37 D/RunUtil: Running command null without timeout.
11-19 20:31:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:38 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:38 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:38 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:38 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:38 D/RunUtil: Running command null without timeout.
11-19 20:31:39 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:39 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:39 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:39 D/RunUtil: Running command null without timeout.
11-19 20:31:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:39 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:31:39 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:31:39 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:31:39 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:31:41 D/RunUtil: Running command null without timeout.
11-19 20:31:41 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:41 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:41 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:41 D/RunUtil: Running command null without timeout.
11-19 20:31:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:42 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:42 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:31:42 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:42 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_17874125781877502486.txt'] without timeout.
11-19 20:31:42 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:31:42 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:31:42 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:31:42 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:31:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:53 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:31:53 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 856.000000
11-19 20:31:53 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 855.000000
11-19 20:31:53 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 227.000000
11-19 20:31:53 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 856.000000
11-19 20:31:53 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 29.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:31:53 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 102.000000
11-19 20:31:53 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 108.000000
11-19 20:31:53 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2969.000000
11-19 20:31:53 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 12.000000
11-19 20:31:53 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 81.000000
11-19 20:31:53 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3742.000000
11-19 20:31:53 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2884.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 9.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:31:53 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 39.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 67.000000
11-19 20:31:53 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:31:53 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:31:53 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 26.000000
11-19 20:31:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:53 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:31:53 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 856.000000
11-19 20:31:53 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:53 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 855.000000
11-19 20:31:53 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 227.000000
11-19 20:31:53 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 856.000000
11-19 20:31:53 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 29.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:31:53 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 102.000000
11-19 20:31:53 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 108.000000
11-19 20:31:53 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2969.000000
11-19 20:31:53 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 12.000000
11-19 20:31:53 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 81.000000
11-19 20:31:53 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3742.000000
11-19 20:31:53 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2884.000000
11-19 20:31:53 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 9.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:31:53 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 39.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 67.000000
11-19 20:31:53 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:31:53 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 26.000000
11-19 20:31:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:53 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:31:53 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 856.000000
11-19 20:31:53 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:31:53 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 855.000000
11-19 20:31:53 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 227.000000
11-19 20:31:53 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 856.000000
11-19 20:31:53 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 29.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:31:53 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 102.000000
11-19 20:31:53 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 108.000000
11-19 20:31:53 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2969.000000
11-19 20:31:53 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 12.000000
11-19 20:31:53 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 81.000000
11-19 20:31:53 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3742.000000
11-19 20:31:53 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2884.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 9.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:31:53 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 39.000000
11-19 20:31:53 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 67.000000
11-19 20:31:53 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:31:53 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 26.000000
11-19 20:31:53 I/MeasurementPrinter:                    98.0	                OK	                 3740.0	                OK	                            856.0	                OK
11-19 20:31:53 D/RunUtil: Running command null without timeout.
11-19 20:31:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:54 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:54 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:54 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:54 D/RunUtil: Running command null without timeout.
11-19 20:31:54 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:55 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:55 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:55 D/RunUtil: Running command null without timeout.
11-19 20:31:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:55 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:55 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:31:55 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:31:55 I/DeviceStateMonitor: Waiting 359958 ms for device SKBFXYZO0C1V package manager
11-19 20:31:55 I/NativeDeviceStateMonitor: Waiting 359896 ms for device SKBFXYZO0C1V external store
11-19 20:31:57 D/RunUtil: Running command null without timeout.
11-19 20:31:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:57 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:31:57 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:31:57 D/RunUtil: Running command null without timeout.
11-19 20:31:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:31:58 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:31:58 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:31:58 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:31:58 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_9767930504849574631.txt'] without timeout.
11-19 20:31:58 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:31:58 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:31:58 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:31:58 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:32:09 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:09 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:32:09 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 827.000000
11-19 20:32:09 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 826.000000
11-19 20:32:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 253.000000
11-19 20:32:09 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 826.000000
11-19 20:32:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 42.000000
11-19 20:32:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 117.000000
11-19 20:32:09 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 46.000000
11-19 20:32:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2891.000000
11-19 20:32:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:32:09 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3664.000000
11-19 20:32:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2832.000000
11-19 20:32:09 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 47.000000
11-19 20:32:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:32:09 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:32:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:32:09 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:09 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:32:09 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 827.000000
11-19 20:32:09 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:09 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 826.000000
11-19 20:32:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 253.000000
11-19 20:32:09 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 826.000000
11-19 20:32:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 42.000000
11-19 20:32:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 117.000000
11-19 20:32:09 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 46.000000
11-19 20:32:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2891.000000
11-19 20:32:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:32:09 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3664.000000
11-19 20:32:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2832.000000
11-19 20:32:09 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:32:09 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 47.000000
11-19 20:32:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:32:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:32:09 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:09 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:32:09 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 827.000000
11-19 20:32:09 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:09 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 826.000000
11-19 20:32:09 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 253.000000
11-19 20:32:09 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 826.000000
11-19 20:32:09 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 42.000000
11-19 20:32:09 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 117.000000
11-19 20:32:09 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 46.000000
11-19 20:32:09 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2891.000000
11-19 20:32:09 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:32:09 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3664.000000
11-19 20:32:09 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2832.000000
11-19 20:32:09 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 47.000000
11-19 20:32:09 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 85.000000
11-19 20:32:09 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 21.000000
11-19 20:32:09 I/MeasurementPrinter:                    85.0	                OK	                 3659.0	                OK	                            827.0	                OK
11-19 20:32:09 D/RunUtil: Running command null without timeout.
11-19 20:32:09 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:10 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:10 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:10 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:10 D/RunUtil: Running command null without timeout.
11-19 20:32:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:11 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:11 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:11 D/RunUtil: Running command null without timeout.
11-19 20:32:11 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:11 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:11 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:32:11 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:32:11 I/DeviceStateMonitor: Waiting 359958 ms for device SKBFXYZO0C1V package manager
11-19 20:32:11 I/NativeDeviceStateMonitor: Waiting 359897 ms for device SKBFXYZO0C1V external store
11-19 20:32:13 D/RunUtil: Running command null without timeout.
11-19 20:32:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:13 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:13 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:13 D/RunUtil: Running command null without timeout.
11-19 20:32:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:32:14 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:14 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_8992140443410410832.txt'] without timeout.
11-19 20:32:14 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:32:14 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:32:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:32:14 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:32:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:25 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:32:25 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 831.000000
11-19 20:32:25 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 827.000000
11-19 20:32:25 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 257.000000
11-19 20:32:25 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 829.000000
11-19 20:32:25 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 34.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:25 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 81.000000
11-19 20:32:25 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 105.000000
11-19 20:32:25 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2933.000000
11-19 20:32:25 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:32:25 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 63.000000
11-19 20:32:25 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3663.000000
11-19 20:32:25 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2833.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:32:25 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 48.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 52.000000
11-19 20:32:25 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 80.000000
11-19 20:32:25 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:32:25 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:32:25 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:25 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:32:25 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 831.000000
11-19 20:32:25 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:25 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 827.000000
11-19 20:32:25 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 257.000000
11-19 20:32:25 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 829.000000
11-19 20:32:25 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 34.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:25 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 81.000000
11-19 20:32:25 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 105.000000
11-19 20:32:25 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2933.000000
11-19 20:32:25 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:32:25 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 63.000000
11-19 20:32:25 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3663.000000
11-19 20:32:25 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2833.000000
11-19 20:32:25 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:32:25 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 48.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 52.000000
11-19 20:32:25 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 80.000000
11-19 20:32:25 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:32:25 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:25 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:32:25 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 831.000000
11-19 20:32:25 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:25 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 827.000000
11-19 20:32:25 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 257.000000
11-19 20:32:25 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 829.000000
11-19 20:32:25 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 34.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:25 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 81.000000
11-19 20:32:25 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 105.000000
11-19 20:32:25 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2933.000000
11-19 20:32:25 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:32:25 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 63.000000
11-19 20:32:25 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3663.000000
11-19 20:32:25 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2833.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 7.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 2.000000
11-19 20:32:25 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 48.000000
11-19 20:32:25 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 52.000000
11-19 20:32:25 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 80.000000
11-19 20:32:25 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:32:25 I/MeasurementPrinter:                    80.0	                OK	                 3664.0	                OK	                            831.0	                OK
11-19 20:32:25 D/RunUtil: Running command null without timeout.
11-19 20:32:25 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:26 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:26 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:26 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:26 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:26 D/RunUtil: Running command null without timeout.
11-19 20:32:26 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:27 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:27 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:27 D/RunUtil: Running command null without timeout.
11-19 20:32:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:27 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:27 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:32:27 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:32:27 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:32:27 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:32:29 D/RunUtil: Running command null without timeout.
11-19 20:32:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:29 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:29 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:29 D/RunUtil: Running command null without timeout.
11-19 20:32:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:30 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:32:30 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:30 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_17676932636637100685.txt'] without timeout.
11-19 20:32:30 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:32:30 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:32:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:32:30 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:32:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:40 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:32:40 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 815.000000
11-19 20:32:40 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 814.000000
11-19 20:32:40 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 244.000000
11-19 20:32:40 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 814.000000
11-19 20:32:40 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:40 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 102.000000
11-19 20:32:40 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 50.000000
11-19 20:32:40 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2628.000000
11-19 20:32:40 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:32:40 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 83.000000
11-19 20:32:40 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3370.000000
11-19 20:32:40 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2552.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
11-19 20:32:40 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 60.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 71.000000
11-19 20:32:40 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 93.000000
11-19 20:32:40 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:32:40 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:32:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:40 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:32:40 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 815.000000
11-19 20:32:40 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:40 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 814.000000
11-19 20:32:40 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 244.000000
11-19 20:32:40 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 814.000000
11-19 20:32:40 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:40 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 102.000000
11-19 20:32:40 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 50.000000
11-19 20:32:40 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2628.000000
11-19 20:32:40 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:32:40 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 83.000000
11-19 20:32:40 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3370.000000
11-19 20:32:40 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2552.000000
11-19 20:32:40 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
11-19 20:32:40 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 60.000000
11-19 20:32:40 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 71.000000
11-19 20:32:40 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 93.000000
11-19 20:32:40 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:32:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:41 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:32:41 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 815.000000
11-19 20:32:41 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:41 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 814.000000
11-19 20:32:41 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 244.000000
11-19 20:32:41 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 814.000000
11-19 20:32:41 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:32:41 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:41 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:41 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 102.000000
11-19 20:32:41 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 50.000000
11-19 20:32:41 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2628.000000
11-19 20:32:41 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:32:41 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 83.000000
11-19 20:32:41 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3370.000000
11-19 20:32:41 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2552.000000
11-19 20:32:41 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 6.000000
11-19 20:32:41 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 4.000000
11-19 20:32:41 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 60.000000
11-19 20:32:41 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 71.000000
11-19 20:32:41 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 93.000000
11-19 20:32:41 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:32:41 I/MeasurementPrinter:                    93.0	                OK	                 3367.0	                OK	                            815.0	                OK
11-19 20:32:41 D/RunUtil: Running command null without timeout.
11-19 20:32:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:41 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:41 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:41 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:42 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:42 D/RunUtil: Running command null without timeout.
11-19 20:32:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:42 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:42 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:42 D/RunUtil: Running command null without timeout.
11-19 20:32:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:42 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:42 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:32:42 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:32:42 I/DeviceStateMonitor: Waiting 359957 ms for device SKBFXYZO0C1V package manager
11-19 20:32:42 I/NativeDeviceStateMonitor: Waiting 359896 ms for device SKBFXYZO0C1V external store
11-19 20:32:44 D/RunUtil: Running command null without timeout.
11-19 20:32:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:44 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:44 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:44 D/RunUtil: Running command null without timeout.
11-19 20:32:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:45 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:45 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:32:45 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:45 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_16197597049693430207.txt'] without timeout.
11-19 20:32:46 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:32:46 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:32:46 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:32:46 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:32:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:56 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:32:56 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 864.000000
11-19 20:32:56 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 864.000000
11-19 20:32:56 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 227.000000
11-19 20:32:56 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 865.000000
11-19 20:32:56 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 7.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:56 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 92.000000
11-19 20:32:56 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 62.000000
11-19 20:32:56 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2719.000000
11-19 20:32:56 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:32:56 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 82.000000
11-19 20:32:56 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3518.000000
11-19 20:32:56 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2651.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:32:56 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 57.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 67.000000
11-19 20:32:56 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 102.000000
11-19 20:32:56 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:32:56 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 11.000000
11-19 20:32:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:56 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:32:56 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 864.000000
11-19 20:32:56 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:56 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 864.000000
11-19 20:32:56 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 227.000000
11-19 20:32:56 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 865.000000
11-19 20:32:56 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 7.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:56 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 92.000000
11-19 20:32:56 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 62.000000
11-19 20:32:56 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2719.000000
11-19 20:32:56 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:32:56 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 82.000000
11-19 20:32:56 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3518.000000
11-19 20:32:56 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2651.000000
11-19 20:32:56 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:32:56 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 57.000000
11-19 20:32:56 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 67.000000
11-19 20:32:56 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 102.000000
11-19 20:32:56 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 11.000000
11-19 20:32:56 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:32:57 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:32:57 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 864.000000
11-19 20:32:57 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:32:57 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 864.000000
11-19 20:32:57 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 227.000000
11-19 20:32:57 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 865.000000
11-19 20:32:57 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 7.000000
11-19 20:32:57 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:32:57 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:32:57 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 92.000000
11-19 20:32:57 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 62.000000
11-19 20:32:57 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2719.000000
11-19 20:32:57 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:32:57 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 82.000000
11-19 20:32:57 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3518.000000
11-19 20:32:57 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2651.000000
11-19 20:32:57 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 10.000000
11-19 20:32:57 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:32:57 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 57.000000
11-19 20:32:57 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 67.000000
11-19 20:32:57 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 102.000000
11-19 20:32:57 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 11.000000
11-19 20:32:57 I/MeasurementPrinter:                   102.0	                OK	                 3515.0	                OK	                            864.0	                OK
11-19 20:32:57 D/RunUtil: Running command null without timeout.
11-19 20:32:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:57 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:57 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:57 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:58 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:32:58 D/RunUtil: Running command null without timeout.
11-19 20:32:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:58 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:32:58 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:32:58 D/RunUtil: Running command null without timeout.
11-19 20:32:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:58 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:32:58 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:32:58 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:32:58 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:32:58 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:33:00 D/RunUtil: Running command null without timeout.
11-19 20:33:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:00 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:00 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:00 D/RunUtil: Running command null without timeout.
11-19 20:33:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:01 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:01 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:01 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:01 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:33:01 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:01 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_15927117415682753550.txt'] without timeout.
11-19 20:33:02 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:33:02 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:33:02 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:33:02 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:33:12 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:12 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:33:12 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 850.000000
11-19 20:33:12 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 849.000000
11-19 20:33:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 242.000000
11-19 20:33:12 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 850.000000
11-19 20:33:12 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 40.000000
11-19 20:33:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:33:12 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 133.000000
11-19 20:33:12 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2771.000000
11-19 20:33:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:12 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3556.000000
11-19 20:33:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2700.000000
11-19 20:33:12 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 51.000000
11-19 20:33:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 109.000000
11-19 20:33:12 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:33:12 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:33:12 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:12 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:33:12 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 850.000000
11-19 20:33:12 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:33:12 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 849.000000
11-19 20:33:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 242.000000
11-19 20:33:12 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 850.000000
11-19 20:33:12 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 40.000000
11-19 20:33:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:33:12 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 133.000000
11-19 20:33:12 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2771.000000
11-19 20:33:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:12 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3556.000000
11-19 20:33:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2700.000000
11-19 20:33:12 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:33:12 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 51.000000
11-19 20:33:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 109.000000
11-19 20:33:12 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:33:12 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:12 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:33:12 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 850.000000
11-19 20:33:12 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:33:12 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 849.000000
11-19 20:33:12 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 242.000000
11-19 20:33:12 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 850.000000
11-19 20:33:12 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 40.000000
11-19 20:33:12 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 86.000000
11-19 20:33:12 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 133.000000
11-19 20:33:12 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2771.000000
11-19 20:33:12 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:12 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3556.000000
11-19 20:33:12 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2700.000000
11-19 20:33:12 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 51.000000
11-19 20:33:12 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 109.000000
11-19 20:33:12 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:33:12 I/MeasurementPrinter:                   109.0	                OK	                 3550.0	                OK	                            850.0	                OK
11-19 20:33:12 D/RunUtil: Running command null without timeout.
11-19 20:33:12 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:13 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:13 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:13 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:14 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:14 D/RunUtil: Running command null without timeout.
11-19 20:33:14 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:14 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:14 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:14 D/RunUtil: Running command null without timeout.
11-19 20:33:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:14 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:14 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:33:14 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:33:14 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:33:14 I/NativeDeviceStateMonitor: Waiting 359899 ms for device SKBFXYZO0C1V external store
11-19 20:33:16 D/RunUtil: Running command null without timeout.
11-19 20:33:16 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:16 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:16 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:16 D/RunUtil: Running command null without timeout.
11-19 20:33:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:33:17 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:17 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_5436939360238048926.txt'] without timeout.
11-19 20:33:17 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:33:17 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:33:17 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:33:18 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:33:28 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:28 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:33:28 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 813.000000
11-19 20:33:28 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 812.000000
11-19 20:33:28 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 266.000000
11-19 20:33:28 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 812.000000
11-19 20:33:28 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 31.000000
11-19 20:33:28 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 97.000000
11-19 20:33:28 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 96.000000
11-19 20:33:28 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2718.000000
11-19 20:33:28 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:28 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3498.000000
11-19 20:33:28 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2683.000000
11-19 20:33:28 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 44.000000
11-19 20:33:28 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 84.000000
11-19 20:33:28 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:33:28 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:33:28 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:28 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:33:28 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 813.000000
11-19 20:33:28 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:33:28 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 812.000000
11-19 20:33:28 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 266.000000
11-19 20:33:28 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 812.000000
11-19 20:33:28 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 31.000000
11-19 20:33:28 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 97.000000
11-19 20:33:28 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 96.000000
11-19 20:33:28 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2718.000000
11-19 20:33:28 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:28 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3498.000000
11-19 20:33:28 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2683.000000
11-19 20:33:28 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:33:28 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 44.000000
11-19 20:33:28 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 84.000000
11-19 20:33:28 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:33:28 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:28 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:33:28 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 813.000000
11-19 20:33:28 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:33:28 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 812.000000
11-19 20:33:28 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 266.000000
11-19 20:33:28 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 812.000000
11-19 20:33:28 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 31.000000
11-19 20:33:28 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 97.000000
11-19 20:33:28 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 96.000000
11-19 20:33:28 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2718.000000
11-19 20:33:28 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:28 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3498.000000
11-19 20:33:28 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2683.000000
11-19 20:33:28 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 44.000000
11-19 20:33:28 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 84.000000
11-19 20:33:28 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:33:28 I/MeasurementPrinter:                    84.0	                OK	                 3496.0	                OK	                            813.0	                OK
11-19 20:33:28 D/RunUtil: Running command null without timeout.
11-19 20:33:28 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:29 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:29 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:29 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:29 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:29 D/RunUtil: Running command null without timeout.
11-19 20:33:30 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:30 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:30 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:30 D/RunUtil: Running command null without timeout.
11-19 20:33:30 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:30 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:30 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:33:30 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:33:30 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:33:30 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYZO0C1V external store
11-19 20:33:32 D/RunUtil: Running command null without timeout.
11-19 20:33:32 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:32 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:32 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:32 D/RunUtil: Running command null without timeout.
11-19 20:33:32 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:32 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:32 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:33 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:33 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:33:33 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:33 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_7632179076058989511.txt'] without timeout.
11-19 20:33:33 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:33:33 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:33:33 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:33:33 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:33:44 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:44 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:33:44 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 245.000000
11-19 20:33:44 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 61.000000
11-19 20:33:44 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 123.000000
11-19 20:33:44 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 127.000000
11-19 20:33:44 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2915.000000
11-19 20:33:44 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:44 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3680.000000
11-19 20:33:44 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2869.000000
11-19 20:33:44 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 48.000000
11-19 20:33:44 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:33:44 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:33:44 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:33:44 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:44 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:33:44 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:33:44 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 245.000000
11-19 20:33:44 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 61.000000
11-19 20:33:44 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 123.000000
11-19 20:33:44 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 127.000000
11-19 20:33:44 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2915.000000
11-19 20:33:44 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:44 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3680.000000
11-19 20:33:44 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2869.000000
11-19 20:33:44 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:33:44 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 48.000000
11-19 20:33:44 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:33:44 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:33:44 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:44 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:33:44 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:33:44 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 245.000000
11-19 20:33:44 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 808.000000
11-19 20:33:44 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 61.000000
11-19 20:33:44 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 123.000000
11-19 20:33:44 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 127.000000
11-19 20:33:44 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2915.000000
11-19 20:33:44 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 11.000000
11-19 20:33:44 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3680.000000
11-19 20:33:44 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2869.000000
11-19 20:33:44 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 48.000000
11-19 20:33:44 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 98.000000
11-19 20:33:44 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 17.000000
11-19 20:33:44 I/MeasurementPrinter:                    98.0	                OK	                 3677.0	                OK	                            808.0	                OK
11-19 20:33:44 D/RunUtil: Running command null without timeout.
11-19 20:33:44 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:45 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:45 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:45 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:46 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:46 D/RunUtil: Running command null without timeout.
11-19 20:33:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:46 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:46 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:46 D/RunUtil: Running command null without timeout.
11-19 20:33:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:46 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:46 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:33:46 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:33:46 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:33:46 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:33:48 D/RunUtil: Running command null without timeout.
11-19 20:33:48 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:48 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:33:48 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:33:48 D/RunUtil: Running command null without timeout.
11-19 20:33:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:33:49 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:33:49 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:33:49 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:33:49 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_17903069351092544135.txt'] without timeout.
11-19 20:33:49 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:33:49 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:33:49 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:33:49 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:34:00 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:00 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:34:00 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 791.000000
11-19 20:34:00 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 787.000000
11-19 20:34:00 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 247.000000
11-19 20:34:00 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 789.000000
11-19 20:34:00 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
11-19 20:34:00 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 119.000000
11-19 20:34:00 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 71.000000
11-19 20:34:00 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2877.000000
11-19 20:34:00 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:34:00 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3620.000000
11-19 20:34:00 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2830.000000
11-19 20:34:00 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 46.000000
11-19 20:34:00 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 81.000000
11-19 20:34:00 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:34:00 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:34:00 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:00 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:34:00 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 791.000000
11-19 20:34:00 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:00 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 787.000000
11-19 20:34:00 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 247.000000
11-19 20:34:00 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 789.000000
11-19 20:34:00 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
11-19 20:34:00 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 119.000000
11-19 20:34:00 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 71.000000
11-19 20:34:00 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2877.000000
11-19 20:34:00 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:34:00 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3620.000000
11-19 20:34:00 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2830.000000
11-19 20:34:00 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:34:00 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 46.000000
11-19 20:34:00 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 81.000000
11-19 20:34:00 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:34:00 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:00 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:34:00 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 791.000000
11-19 20:34:00 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:00 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 787.000000
11-19 20:34:00 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 247.000000
11-19 20:34:00 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 789.000000
11-19 20:34:00 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 57.000000
11-19 20:34:00 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 119.000000
11-19 20:34:00 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 71.000000
11-19 20:34:00 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2877.000000
11-19 20:34:00 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:34:00 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3620.000000
11-19 20:34:00 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2830.000000
11-19 20:34:00 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 46.000000
11-19 20:34:00 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 81.000000
11-19 20:34:00 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:34:00 I/MeasurementPrinter:                    81.0	                OK	                 3621.0	                OK	                            791.0	                OK
11-19 20:34:00 D/RunUtil: Running command null without timeout.
11-19 20:34:00 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:01 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:01 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:01 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:01 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:01 D/RunUtil: Running command null without timeout.
11-19 20:34:02 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:02 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:02 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:02 D/RunUtil: Running command null without timeout.
11-19 20:34:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:02 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:02 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:34:02 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:34:02 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:34:02 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:34:04 D/RunUtil: Running command null without timeout.
11-19 20:34:04 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:04 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:04 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:04 D/RunUtil: Running command null without timeout.
11-19 20:34:04 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:04 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:04 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:05 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:05 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:34:05 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:05 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_10327373802195385701.txt'] without timeout.
11-19 20:34:05 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:34:05 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:34:05 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:34:05 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:34:15 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:15 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:34:15 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 781.000000
11-19 20:34:15 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 781.000000
11-19 20:34:15 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 236.000000
11-19 20:34:15 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 782.000000
11-19 20:34:15 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 25.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:34:15 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 116.000000
11-19 20:34:15 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 114.000000
11-19 20:34:15 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2654.000000
11-19 20:34:15 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:34:15 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 103.000000
11-19 20:34:15 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3345.000000
11-19 20:34:15 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2562.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 5.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:34:15 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 42.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 93.000000
11-19 20:34:15 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 112.000000
11-19 20:34:15 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:34:15 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
11-19 20:34:15 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:15 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:34:15 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 781.000000
11-19 20:34:15 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:15 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 781.000000
11-19 20:34:15 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 236.000000
11-19 20:34:15 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 782.000000
11-19 20:34:15 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 25.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:34:15 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 116.000000
11-19 20:34:15 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 114.000000
11-19 20:34:15 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2654.000000
11-19 20:34:15 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:34:15 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 103.000000
11-19 20:34:15 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3345.000000
11-19 20:34:15 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2562.000000
11-19 20:34:15 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 5.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:34:15 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 42.000000
11-19 20:34:15 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 93.000000
11-19 20:34:15 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 112.000000
11-19 20:34:15 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
11-19 20:34:15 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:16 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:34:16 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 781.000000
11-19 20:34:16 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:16 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 781.000000
11-19 20:34:16 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 236.000000
11-19 20:34:16 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 782.000000
11-19 20:34:16 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 25.000000
11-19 20:34:16 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:34:16 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:34:16 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 116.000000
11-19 20:34:16 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 114.000000
11-19 20:34:16 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2654.000000
11-19 20:34:16 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:34:16 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 103.000000
11-19 20:34:16 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3345.000000
11-19 20:34:16 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2562.000000
11-19 20:34:16 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 5.000000
11-19 20:34:16 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 3.000000
11-19 20:34:16 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 42.000000
11-19 20:34:16 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 93.000000
11-19 20:34:16 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 112.000000
11-19 20:34:16 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 13.000000
11-19 20:34:16 I/MeasurementPrinter:                   112.0	                OK	                 3343.0	                OK	                            781.0	                OK
11-19 20:34:16 D/RunUtil: Running command null without timeout.
11-19 20:34:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:16 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:16 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:16 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:17 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:17 D/RunUtil: Running command null without timeout.
11-19 20:34:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:17 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:17 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:17 D/RunUtil: Running command null without timeout.
11-19 20:34:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:17 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:17 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:34:17 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:34:17 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:34:17 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:34:19 D/RunUtil: Running command null without timeout.
11-19 20:34:19 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:19 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:19 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:19 D/RunUtil: Running command null without timeout.
11-19 20:34:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:20 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:34:20 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:20 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_13210688913588307608.txt'] without timeout.
11-19 20:34:21 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:34:21 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:34:21 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:34:21 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:34:31 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:31 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:34:31 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 795.000000
11-19 20:34:31 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 794.000000
11-19 20:34:31 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 246.000000
11-19 20:34:31 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 796.000000
11-19 20:34:31 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:34:31 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 106.000000
11-19 20:34:31 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 31.000000
11-19 20:34:31 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2576.000000
11-19 20:34:31 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:34:31 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3327.000000
11-19 20:34:31 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2525.000000
11-19 20:34:31 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 44.000000
11-19 20:34:31 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 67.000000
11-19 20:34:31 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:34:31 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:34:31 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:31 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:34:31 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 795.000000
11-19 20:34:31 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:31 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 794.000000
11-19 20:34:31 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 246.000000
11-19 20:34:31 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 796.000000
11-19 20:34:31 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:34:31 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 106.000000
11-19 20:34:31 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 31.000000
11-19 20:34:31 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2576.000000
11-19 20:34:31 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:34:31 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3327.000000
11-19 20:34:31 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2525.000000
11-19 20:34:31 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:34:31 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 44.000000
11-19 20:34:31 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 67.000000
11-19 20:34:31 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:34:31 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:31 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:34:31 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 795.000000
11-19 20:34:31 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:31 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 794.000000
11-19 20:34:31 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 246.000000
11-19 20:34:31 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 796.000000
11-19 20:34:31 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 39.000000
11-19 20:34:31 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 106.000000
11-19 20:34:31 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 31.000000
11-19 20:34:31 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2576.000000
11-19 20:34:31 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 10.000000
11-19 20:34:31 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3327.000000
11-19 20:34:31 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2525.000000
11-19 20:34:31 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 44.000000
11-19 20:34:31 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 67.000000
11-19 20:34:31 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 16.000000
11-19 20:34:31 I/MeasurementPrinter:                    67.0	                OK	                 3320.0	                OK	                            795.0	                OK
11-19 20:34:31 D/RunUtil: Running command null without timeout.
11-19 20:34:31 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:32 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:32 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:32 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:33 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:33 D/RunUtil: Running command null without timeout.
11-19 20:34:33 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:33 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:33 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:33 D/RunUtil: Running command null without timeout.
11-19 20:34:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:33 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:33 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:34:33 I/NativeDeviceStateMonitor: Waiting 359999 ms for device SKBFXYZO0C1V boot complete
11-19 20:34:33 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:34:33 I/NativeDeviceStateMonitor: Waiting 359895 ms for device SKBFXYZO0C1V external store
11-19 20:34:35 D/RunUtil: Running command null without timeout.
11-19 20:34:35 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:35 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:35 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:35 D/RunUtil: Running command null without timeout.
11-19 20:34:35 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:35 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:35 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:36 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:36 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:34:36 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:36 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_10991688797933547584.txt'] without timeout.
11-19 20:34:36 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:34:36 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:34:36 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:34:36 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:34:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:47 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:34:47 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 859.000000
11-19 20:34:47 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 858.000000
11-19 20:34:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:34:47 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 859.000000
11-19 20:34:47 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 40.000000
11-19 20:34:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 105.000000
11-19 20:34:47 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 152.000000
11-19 20:34:47 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2923.000000
11-19 20:34:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:34:47 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3688.000000
11-19 20:34:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2825.000000
11-19 20:34:47 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 38.000000
11-19 20:34:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 90.000000
11-19 20:34:47 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:34:47 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
11-19 20:34:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:47 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:34:47 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 859.000000
11-19 20:34:47 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:47 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 858.000000
11-19 20:34:47 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:34:47 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 859.000000
11-19 20:34:47 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 40.000000
11-19 20:34:47 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 105.000000
11-19 20:34:47 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 152.000000
11-19 20:34:47 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2923.000000
11-19 20:34:47 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:34:47 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3688.000000
11-19 20:34:47 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2825.000000
11-19 20:34:47 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:34:47 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 38.000000
11-19 20:34:47 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 90.000000
11-19 20:34:47 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
11-19 20:34:47 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:48 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:34:48 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 859.000000
11-19 20:34:48 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:34:48 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 858.000000
11-19 20:34:48 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 238.000000
11-19 20:34:48 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 859.000000
11-19 20:34:48 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 40.000000
11-19 20:34:48 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 105.000000
11-19 20:34:48 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 152.000000
11-19 20:34:48 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2923.000000
11-19 20:34:48 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:34:48 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3688.000000
11-19 20:34:48 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2825.000000
11-19 20:34:48 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 38.000000
11-19 20:34:48 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 90.000000
11-19 20:34:48 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 19.000000
11-19 20:34:48 I/MeasurementPrinter:                    90.0	                OK	                 3684.0	                OK	                            859.0	                OK
11-19 20:34:48 D/RunUtil: Running command null without timeout.
11-19 20:34:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:48 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:48 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:48 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:49 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:49 D/RunUtil: Running command null without timeout.
11-19 20:34:49 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:49 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:49 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:49 D/RunUtil: Running command null without timeout.
11-19 20:34:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:49 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:49 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:34:49 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:34:49 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:34:49 I/NativeDeviceStateMonitor: Waiting 359900 ms for device SKBFXYZO0C1V external store
11-19 20:34:51 D/RunUtil: Running command null without timeout.
11-19 20:34:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:51 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:34:51 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:34:51 D/RunUtil: Running command null without timeout.
11-19 20:34:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:34:52 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:34:52 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:34:52 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:34:52 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_9971835013470039098.txt'] without timeout.
11-19 20:34:53 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:34:53 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:34:53 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:34:53 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:35:03 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:03 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:35:03 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 836.000000
11-19 20:35:03 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 835.000000
11-19 20:35:03 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 255.000000
11-19 20:35:03 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 836.000000
11-19 20:35:03 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 51.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:35:03 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 98.000000
11-19 20:35:03 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 73.000000
11-19 20:35:03 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2608.000000
11-19 20:35:03 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:35:03 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 87.000000
11-19 20:35:03 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3398.000000
11-19 20:35:03 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2560.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:35:03 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 39.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 72.000000
11-19 20:35:03 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 101.000000
11-19 20:35:03 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:35:03 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:35:03 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:03 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:35:03 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 836.000000
11-19 20:35:03 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:03 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 835.000000
11-19 20:35:03 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 255.000000
11-19 20:35:03 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 836.000000
11-19 20:35:03 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 51.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:35:03 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 98.000000
11-19 20:35:03 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 73.000000
11-19 20:35:03 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2608.000000
11-19 20:35:03 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:35:03 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 87.000000
11-19 20:35:03 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3398.000000
11-19 20:35:03 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2560.000000
11-19 20:35:03 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:35:03 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 39.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 72.000000
11-19 20:35:03 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 101.000000
11-19 20:35:03 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:35:03 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:03 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:35:03 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 836.000000
11-19 20:35:03 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:03 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 835.000000
11-19 20:35:03 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 255.000000
11-19 20:35:03 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 836.000000
11-19 20:35:03 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 51.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_start_to_new_intent: size = 1, sum: 1.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_new_intent_to_resume: size = 1, sum: 1.000000
11-19 20:35:03 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 98.000000
11-19 20:35:03 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 73.000000
11-19 20:35:03 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2608.000000
11-19 20:35:03 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 13.000000
11-19 20:35:03 D/ProtoMeasurementBase: new_assistant_request_intent_to_ui_hot: size = 1, sum: 87.000000
11-19 20:35:03 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3398.000000
11-19 20:35:03 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2560.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_restart_to_start: size = 1, sum: 8.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_service_on_start_command_to_restart: size = 1, sum: 5.000000
11-19 20:35:03 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 39.000000
11-19 20:35:03 D/ProtoMeasurementBase: hot_voiceplate_activity_resume_to_first_draw: size = 1, sum: 72.000000
11-19 20:35:03 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 101.000000
11-19 20:35:03 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 24.000000
11-19 20:35:03 I/MeasurementPrinter:                   101.0	                OK	                 3396.0	                OK	                            836.0	                OK
11-19 20:35:03 D/RunUtil: Running command null without timeout.
11-19 20:35:03 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:04 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:04 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:04 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:04 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:04 D/RunUtil: Running command null without timeout.
11-19 20:35:05 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:05 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:05 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:05 D/RunUtil: Running command null without timeout.
11-19 20:35:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:05 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:05 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:35:05 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:35:05 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:35:05 I/NativeDeviceStateMonitor: Waiting 359902 ms for device SKBFXYZO0C1V external store
11-19 20:35:07 D/RunUtil: Running command null without timeout.
11-19 20:35:07 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:07 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:07 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:07 D/RunUtil: Running command null without timeout.
11-19 20:35:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:07 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:08 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:08 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:35:08 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:08 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_10761586444362044838.txt'] without timeout.
11-19 20:35:08 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:35:08 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:35:08 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:35:08 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:35:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:19 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:35:19 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 823.000000
11-19 20:35:19 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 822.000000
11-19 20:35:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 268.000000
11-19 20:35:19 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 823.000000
11-19 20:35:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 51.000000
11-19 20:35:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 132.000000
11-19 20:35:19 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 73.000000
11-19 20:35:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2985.000000
11-19 20:35:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:35:19 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3775.000000
11-19 20:35:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2947.000000
11-19 20:35:19 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 63.000000
11-19 20:35:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 73.000000
11-19 20:35:19 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:35:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:35:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:35:19 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 823.000000
11-19 20:35:19 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:19 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 822.000000
11-19 20:35:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 268.000000
11-19 20:35:19 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 823.000000
11-19 20:35:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 51.000000
11-19 20:35:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 132.000000
11-19 20:35:19 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 73.000000
11-19 20:35:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2985.000000
11-19 20:35:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:35:19 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3775.000000
11-19 20:35:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2947.000000
11-19 20:35:19 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:35:19 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 63.000000
11-19 20:35:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 73.000000
11-19 20:35:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:35:19 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:19 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:35:19 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 823.000000
11-19 20:35:19 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:19 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 822.000000
11-19 20:35:19 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 268.000000
11-19 20:35:19 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 823.000000
11-19 20:35:19 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 51.000000
11-19 20:35:19 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 132.000000
11-19 20:35:19 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 73.000000
11-19 20:35:19 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2985.000000
11-19 20:35:19 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:35:19 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3775.000000
11-19 20:35:19 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2947.000000
11-19 20:35:19 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 63.000000
11-19 20:35:19 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 73.000000
11-19 20:35:19 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 18.000000
11-19 20:35:19 I/MeasurementPrinter:                    73.0	                OK	                 3770.0	                OK	                            823.0	                OK
11-19 20:35:19 D/RunUtil: Running command null without timeout.
11-19 20:35:19 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:20 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:20 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:20 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:21 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:21 D/RunUtil: Running command null without timeout.
11-19 20:35:21 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:21 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:21 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:21 D/RunUtil: Running command null without timeout.
11-19 20:35:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:21 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:21 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:35:21 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:35:21 I/DeviceStateMonitor: Waiting 359964 ms for device SKBFXYZO0C1V package manager
11-19 20:35:21 I/NativeDeviceStateMonitor: Waiting 359903 ms for device SKBFXYZO0C1V external store
11-19 20:35:23 D/RunUtil: Running command null without timeout.
11-19 20:35:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:23 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:23 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:23 D/RunUtil: Running command null without timeout.
11-19 20:35:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:23 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:24 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:35:24 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:24 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_11739382467698497906.txt'] without timeout.
11-19 20:35:24 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:35:24 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:35:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:35:24 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:35:34 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:35 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:35:35 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 826.000000
11-19 20:35:35 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 825.000000
11-19 20:35:35 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 236.000000
11-19 20:35:35 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 828.000000
11-19 20:35:35 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 45.000000
11-19 20:35:35 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 94.000000
11-19 20:35:35 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 92.000000
11-19 20:35:35 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2602.000000
11-19 20:35:35 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:35:35 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3364.000000
11-19 20:35:35 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2534.000000
11-19 20:35:35 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 55.000000
11-19 20:35:35 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
11-19 20:35:35 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:35:35 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 30.000000
11-19 20:35:35 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:35 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:35:35 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 826.000000
11-19 20:35:35 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:35 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 825.000000
11-19 20:35:35 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 236.000000
11-19 20:35:35 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 828.000000
11-19 20:35:35 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 45.000000
11-19 20:35:35 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 94.000000
11-19 20:35:35 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 92.000000
11-19 20:35:35 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2602.000000
11-19 20:35:35 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:35:35 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3364.000000
11-19 20:35:35 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2534.000000
11-19 20:35:35 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:35:35 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 55.000000
11-19 20:35:35 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
11-19 20:35:35 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 30.000000
11-19 20:35:35 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:35 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:35:35 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 826.000000
11-19 20:35:35 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:35 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 825.000000
11-19 20:35:35 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 236.000000
11-19 20:35:35 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 828.000000
11-19 20:35:35 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 45.000000
11-19 20:35:35 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 94.000000
11-19 20:35:35 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 92.000000
11-19 20:35:35 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2602.000000
11-19 20:35:35 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 9.000000
11-19 20:35:35 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3364.000000
11-19 20:35:35 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2534.000000
11-19 20:35:35 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 55.000000
11-19 20:35:35 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 100.000000
11-19 20:35:35 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 30.000000
11-19 20:35:35 I/MeasurementPrinter:                   100.0	                OK	                 3360.0	                OK	                            826.0	                OK
11-19 20:35:35 D/RunUtil: Running command null without timeout.
11-19 20:35:35 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:36 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:36 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:36 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:36 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:36 D/RunUtil: Running command null without timeout.
11-19 20:35:36 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:36 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:36 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:36 D/RunUtil: Running command null without timeout.
11-19 20:35:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:37 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:37 I/NativeDeviceStateMonitor: Device SKBFXYZO0C1V is already ONLINE
11-19 20:35:37 I/NativeDeviceStateMonitor: Waiting 360000 ms for device SKBFXYZO0C1V boot complete
11-19 20:35:37 I/DeviceStateMonitor: Waiting 359963 ms for device SKBFXYZO0C1V package manager
11-19 20:35:37 I/NativeDeviceStateMonitor: Waiting 359901 ms for device SKBFXYZO0C1V external store
11-19 20:35:39 D/RunUtil: Running command null without timeout.
11-19 20:35:39 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:39 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:39 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:39 D/RunUtil: Running command null without timeout.
11-19 20:35:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:39 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:40 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:40 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, logcat, -c, -b, all] with timeout: 2m 0s
11-19 20:35:40 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:40 D/RunUtil: Running command [/bin/bash, -c, 'rm' '-f' '/data/tmp/8d2a5cd0-f354-4907-b932-f65af78ac24a/tmp/katniss-primes-2024-11-19T03_30_32.742_2377465178622294907.txt'] without timeout.
11-19 20:35:40 D/AppRunnerUtils: Cannot find process for package com.google.android.assistant.tvts
11-19 20:35:40 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.assistant.tvts
11-19 20:35:40 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.assistant.tvts] with timeout: 2m 0s
11-19 20:35:40 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, instrument, -e, class, com.google.android.assistant.tvts.MoonTest, -w, com.google.android.assistant.tvts/androidx.test.runner.AndroidJUnitRunner] with timeout: 4m 10s
11-19 20:35:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:51 D/ProtoMeasurementBase: Begin Parse: search_to_query_latency
11-19 20:35:51 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 1369.000000
11-19 20:35:51 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 1368.000000
11-19 20:35:51 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 222.000000
11-19 20:35:51 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 1370.000000
11-19 20:35:51 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:35:51 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:35:51 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 265.000000
11-19 20:35:51 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2688.000000
11-19 20:35:51 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:35:51 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3969.000000
11-19 20:35:51 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2596.000000
11-19 20:35:51 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 70.000000
11-19 20:35:51 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 76.000000
11-19 20:35:51 D/ProtoMeasurementBase: Adding required latency: assistant_request_intent_to_ui
11-19 20:35:51 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 12.000000
11-19 20:35:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:51 D/ProtoMeasurementBase: Begin Parse: query_to_result_latency
11-19 20:35:51 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 1369.000000
11-19 20:35:51 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:51 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 1368.000000
11-19 20:35:51 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 222.000000
11-19 20:35:51 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 1370.000000
11-19 20:35:51 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:35:51 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:35:51 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 265.000000
11-19 20:35:51 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2688.000000
11-19 20:35:51 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:35:51 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3969.000000
11-19 20:35:51 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2596.000000
11-19 20:35:51 D/ProtoMeasurementBase: Adding required latency: query_recognized_to_result
11-19 20:35:51 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 70.000000
11-19 20:35:51 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 76.000000
11-19 20:35:51 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 12.000000
11-19 20:35:51 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:51 D/ProtoMeasurementBase: Begin Parse: query_to_result_no_server_latency
11-19 20:35:51 D/ProtoMeasurementBase: result_displayed_card: size = 1, sum: 1369.000000
11-19 20:35:51 D/ProtoMeasurementBase: Adding required latency: result_displayed_card
11-19 20:35:51 D/ProtoMeasurementBase: new_result_displayed_card_warm: size = 1, sum: 1368.000000
11-19 20:35:51 D/ProtoMeasurementBase: fetch_zerostate_suggestions_from_server: size = 1, sum: 222.000000
11-19 20:35:51 D/ProtoMeasurementBase: e2e_client_card_response: size = 1, sum: 1370.000000
11-19 20:35:51 D/ProtoMeasurementBase: searchbar_state_talking_idle: size = 3, sum: 35.000000
11-19 20:35:51 D/ProtoMeasurementBase: searchbar_state_loading: size = 1, sum: 91.000000
11-19 20:35:51 D/ProtoMeasurementBase: webview_content_loading: size = 1, sum: 265.000000
11-19 20:35:51 D/ProtoMeasurementBase: query_recognized_to_tts_start: size = 1, sum: 2688.000000
11-19 20:35:51 D/ProtoMeasurementBase: app_start_to_vpa_visible: size = 1, sum: 8.000000
11-19 20:35:51 D/ProtoMeasurementBase: e2e_card_response: size = 1, sum: 3969.000000
11-19 20:35:51 D/ProtoMeasurementBase: query_recognized_to_result: size = 1, sum: 2596.000000
11-19 20:35:51 D/ProtoMeasurementBase: view_add_card: size = 1, sum: 70.000000
11-19 20:35:51 D/ProtoMeasurementBase: assistant_request_intent_to_ui: size = 1, sum: 76.000000
11-19 20:35:51 D/ProtoMeasurementBase: result_across_process: size = 1, sum: 12.000000
11-19 20:35:51 I/MeasurementPrinter:                    76.0	                OK	                 3965.0	                OK	                           1369.0	                OK
11-19 20:35:51 D/RunUtil: Running command null without timeout.
11-19 20:35:51 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:52 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:52 D/AppRunnerUtils: waitUntilAppInForeground(): Checking activity: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:52 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:53 D/AppRunnerUtils: getActivityShownByPackage(): ActivityName: com.skb.google.tv.main.MainActivity.
11-19 20:35:53 D/RunUtil: Running command null without timeout.
11-19 20:35:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:53 D/AppRunnerUtils: getHomeActivityName(): launcherActivityName: com.skb.tv/com.skb.google.tv.main.MainActivity
11-19 20:35:53 D/AppRunnerUtils: pressHomeUntilBackHome(): poll time: 500  totalTime: 4000  attempts: 8
11-19 20:35:53 D/RunUtil: Running command null without timeout.
11-19 20:35:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:53 D/AppRunnerUtils: foregroundActivitySet(): [com.skb.tv/com.skb.google.tv.main.MainActivity]
11-19 20:35:53 D/AppRunnerUtils: Running the following command: am force-stop com.google.android.katniss
11-19 20:35:53 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, am, force-stop, com.google.android.katniss] with timeout: 2m 0s
11-19 20:35:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:53 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:54 D/NativeDevice: Using property ro.build.version.sdk=31 from cache.
11-19 20:35:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, getprop, ro.config.low_ram] with timeout: 45s
11-19 20:35:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, pm, list, features] with timeout: 2m 0s
11-19 20:35:54 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYZO0C1V
11-19 20:35:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, getprop, ro.config.low_ram] with timeout: 45s
11-19 20:35:54 D/RunUtil: Running command [adb, -s, SKBFXYZO0C1V, shell, pm, list, features] with timeout: 2m 0s
11-19 20:35:54 W/TestDevice: Feature: feature:com.google.android.feature.AMATI_EXPERIENCE is not available on SKBFXYZO0C1V
11-19 20:35:54 I/BasicAggregationTypeBase: Checking if collection is initialized with data
11-19 20:35:54 I/BasicAggregationTypeBase: Checking if collection is initialized with data
11-19 20:35:54 D/PrettyTestEventLogger: 
==================== com.google.android.assistant.v4.tvts.TvtsAssistant4Test#testDistanceToTheMoon ENDED: Tue Nov 19 20:35:54 KST 2024 ====================
